前言

工作日誌(Log)是將除錯訊息寫入檔案、或顯示在螢幕上，甚至傳給遠端的電腦，主要是要記錄執行過程，萬一使用者操作系統發生錯誤時，能回頭追查原因，是開發中大型系統必備的機制，不論是何種程式語言都支援類似的函數庫，例如Java的log4j、C#的log4net、Python內建的logging模組，作法都大同小異，以下就來好好研究相關的用法及應用實務。

注意，工作日誌與一般的檔案I/O不同，它支援多個程式或執行緒同時寫入，不會被鎖住(Thread safe)，因此，在多執行緒的應用程式中，例如網頁程式，千萬不要使用一般的檔案取代工作日誌，否則程式會卡住，進而引發錯誤。

logging模組入門

使用工作日誌分為3個工作：

1. 設定工作日誌組態。
2. 寫入工作日誌。
3. 監看工作日誌。
   以下我們逐項測試相關功能。

設定工作日誌組態(Configuration)

工作日誌可以設定訊息的等級(Level)以及輸出的格式(Format)。工作日誌的訊息等級預設分為5個等級：

1. debug：除錯，以logging.DEBUG常數表示。
2. info：資訊，以logging.INFO常數表示。
3. warning：警告，以logging.WARNING常數表示。
4. error：錯誤，以logging.ERROR常數表示。
5. critical：關鍵資訊，以logging.CRITICAL常數表示。

在程式中可設定要顯示的訊息等級，例如將等級設定為info，則info及以上等級(warning、error、critical)的訊息才會寫入工作日誌檔，debug等級的訊息不會寫入，通常我們會將等級設定為info，要除錯時，才將等級設定放寬為debug，才不會寫入太多訊息至工作日誌檔，影響系統效能，如果還不放心，也可提高到error等級，只有程式錯誤才記錄。

工作日誌檔的格式也可以自訂，通常會包括日期/時間、訊息等級及訊息本身，如果為網頁程式，我們可能也希望記錄操作的使用者帳號或session id，其他的訊息欄位可參考【Logging facility for Python】。

圖一. 部分訊息欄位列表

掌握了基本概念後，廢話不多說，我們就開始來實作。

範例1. 工作日誌檔測試，檔案名稱為log1.py。

from datetime import datetime
import os, logging

# 建立log資料夾
os.makedirs('log', exist_ok=True)  # Create the directory if it doesn't exist

logger = logging.getLogger(__name__)
# 取得【年月日時分】的字串，作為檔名的一部分。
date_time = datetime.now().strftime("%Y_%m_%d_%H_%M_%S")
# 設定工作日誌檔的檔名、欄位及內碼，及要寫入的等級
logging.basicConfig(filename=f'log/{date_time}.log', 
    format='%(asctime)s %(levelname)s:%(message)s', datefmt='%I:%M:%S', 
    encoding='utf-8', level=logging.DEBUG)

# 測試
logging.debug("除錯")
logging.info("資訊")
logging.warning("警告")
logging.error("錯誤")
logging.critical("關鍵資訊")

執行結果：log/2024_09_19_15_24.log檔案內容如下。

03:25:25 DEBUG:除錯
03:25:25 INFO:資訊
03:25:25 WARNING:警告
03:25:25 ERROR:錯誤
03:25:25 CRITICAL:關鍵資訊

將level改為logging.INFO。

logging.basicConfig(filename=f'log/{date_time}.log', 
    format='%(asctime)s %(levelname)s:%(message)s', datefmt='%I:%M:%S', 
    encoding='utf-8', level=logging.INFO)

執行結果：【DEBUG:除錯】訊息不會寫入檔案。

實務作法

實務上，工作日誌規劃如下：

1. 使用一個工作日誌檔資料量會太大，通常會設定一天一個工作日誌檔，如果使用人數很多，也可設定為每小時一個工作日誌檔，相關控制可以使用檔名來設定。
2. 平常將工作日誌預設等級設定為logging.INFO，要除錯時將等級設定為logging.DEBUG，若是網頁程式可以設定一個URL可以改變等級或將預設等級設定在組態檔。
3. 注意，工作日誌必須寫在程式的最前面，除了import。

範例2. 工作日誌檔案名稱命名規則。

1. 一天一個工作日誌檔，工作日誌檔案名稱設定如下。

# 【年月日】
date_time = datetime.now().strftime("%Y_%m_%d")
# 設定工作日誌檔的檔名、欄位及內碼，及要寫入的等級
logging.basicConfig(filename=f'log/{date_time}.log', 
    format='%(asctime)s %(levelname)s:%(message)s', datefmt='%I:%M:%S', 
    encoding='utf-8', level=logging.DEBUG)

2. 每小時一個工作日誌檔，設定如下。

# 【年月日時】
date_time = datetime.now().strftime("%Y_%m_%d_%H")
# 設定工作日誌檔的檔名、欄位及內碼，及要寫入的等級
logging.basicConfig(filename=f'log/{date_time}.log', 
    format='%(asctime)s %(levelname)s:%(message)s', datefmt='%I:%M:%S', 
    encoding='utf-8', level=logging.DEBUG)

3. 使用自訂的logger【TimedRotatingFileHandler】，可參閱【How to create a log file every day using logging module?】作法。

範例3. 平常將工作日誌預設等級設定為logging.INFO，要除錯時將等級設放寬為logging.DEBUG。

1. 要修改等級，不需重啟動，程式碼如下：

logging.getLogger().setLevel(logging.DEBUG)

2. 測試：程式名稱為log_set_level.py。

from datetime import datetime
import os, logging

logger = logging.getLogger(__name__)
# 取得【年月日時分】的字串，作為檔名的一部分。
date_time = datetime.now().strftime("%Y_%m_%d_%H_%M")
# 設定工作日誌檔的檔名、欄位及內碼，及要寫入的等級
logging.basicConfig(filename=f'log/{date_time}.log', 
    format='%(asctime)s %(levelname)s:%(message)s', datefmt='%I:%M:%S', 
    encoding='utf-8', level=logging.INFO)

# 測試
logging.info("set level to INFO")
logging.debug("除錯")
logging.info("資訊")
logging.warning("警告")
logging.error("錯誤")
logging.critical("關鍵資訊")

logging.getLogger().setLevel(logging.DEBUG) # 修改等級

# 測試
logging.debug("set level to DEBUG")
logging.debug("除錯")
logging.info("資訊")
logging.warning("警告")
logging.error("錯誤")
logging.critical("關鍵資訊")

3. 執行結果：放寬為logging.DEBUG，DEBUG等級的訊息會寫入至工作日誌。

09:34:57 INFO:set level to INFO
09:34:57 INFO:資訊
09:34:57 WARNING:警告
09:34:57 ERROR:錯誤
09:34:57 CRITICAL:關鍵資訊
09:34:57 DEBUG:set level to DEBUG
09:34:57 DEBUG:除錯
09:34:57 INFO:資訊
09:34:57 WARNING:警告
09:34:57 ERROR:錯誤
09:34:57 CRITICAL:關鍵資訊

範例4. 工作日誌必須寫在程式的最前面，若在設定之前先加一行logging.error("錯誤")，工作日誌顯示在螢幕上，並會造成奇怪的結果，程式名稱為log_error.py。

1. 程式內容：

from datetime import datetime
import os, logging

logging.error("錯誤") # 在設定之前先寫入訊息

logger = logging.getLogger(__name__)
# 取得【年月日時分】的字串，作為檔名的一部分。
date_time = datetime.now().strftime("%Y_%m_%d_%H_%M")
# 設定工作日誌檔的檔名、欄位及內碼，及要寫入的等級
logging.basicConfig(filename=f'log/{date_time}.log', 
    format='%(asctime)s %(levelname)s:%(message)s', datefmt='%I:%M:%S', 
    encoding='utf-8', level=logging.DEBUG)

# 測試
logging.debug("除錯")
logging.info("資訊")
logging.warning("警告")
logging.error("錯誤")
logging.critical("關鍵資訊")

2. 執行結果：工作日誌顯示在螢幕上，並會造成奇怪的結果。

ERROR:root:錯誤
WARNING:root:警告
ERROR:root:錯誤
CRITICAL:root:關鍵資訊

Decorator + logging

範例5. 將Decorator訊息寫入工作日誌檔，複製6/decorator1.py修改如下。

print("呼叫函數前")

改為：

logging.debug(f"呼叫函數{func.__name__}前")

執行結果：

10:58:58 DEBUG:呼叫函數say_hello前
10:58:58 DEBUG:呼叫函數say_hello後

自訂Logger

預設的工作日誌稱為Root logger，可以從上面的執行結果觀察到，Python也允許開發者自訂工作日誌，功能包括：

1. 同時輸出至多種裝置，例如螢幕、檔案、網路...。
2. 支援特殊處理器(handler)，例如

• RotatingFileHandler：可以限制工作日誌檔的大小(Size)，一旦超過，就會刪除最早的訊息
• TimedRotatingFileHandler：可以限制工作日誌檔只保留最近一段時間的訊息
• SocketHandler：可透過Socket通訊協定傳給其他程式或遠端電腦。
• 更多的Handler可參閱【https://docs.python.org/3/library/logging.handlers.html】 。

3. 支援多個工作日誌檔。

以下就逐一來測試相關功能。

範例6. 自訂工作日誌，同時輸出至螢幕及檔案，程式名稱為custom_log1.py。

1. 先建立logger。

import os, logging

# 建立log資料夾
os.makedirs('log', exist_ok=True)  

# 自訂工作日誌(logger)
logger = logging.getLogger(__name__)

2. 訂定 handlers，並指定logger的handlers。

# 訂定 handlers
console_handler = logging.StreamHandler()
file_handler = logging.FileHandler("log/app.log", mode="a", encoding="utf-8")

# 指定logger的handlers
logger.addHandler(console_handler)
logger.addHandler(file_handler)

3. 顯示handlers及工作日誌預設等級。

print(f'handlers：{logger.handlers}')
print(f'default level：{logger.level}')
print(f'EffectiveLevel：{logger.getEffectiveLevel()}')

4. 測試。

logger.debug("除錯")
logger.info("資訊")
logger.warning("警告")

5. 執行結果：螢幕及工作日誌檔案都只出現【警告】，因為預設等級為0，表未設定等級，預設為warning等級。

handlers：[<StreamHandler <stderr> (NOTSET)>, <FileHandler F:\0_python\00_MY\0_ITHome\src\8\log\app.log (NOTSET)>]
default level：0
EffectiveLevel：30
警告

圖二. 工作日誌等級列表及代碼

範例7. 可至logger或handler設定等級，訊息欄位則限於handler，程式名稱為custom_log2.py。

1. 增加程式碼，設定等級及訊息欄位。

# 設定等級
logger.setLevel("DEBUG")
console_handler.setLevel("DEBUG")
file_handler.setLevel("WARNING")

# 設定訊息欄位
formatter = logging.Formatter("{levelname} - {message}", style="{")
logger.setFormatter(formatter)
console_handler.setFormatter(formatter)
file_handler.setFormatter(formatter)

2. 執行結果：

• 螢幕出現：

handlers：[<StreamHandler <stderr> (NOTSET)>, <FileHandler F:\0_python\00_MY\0_ITHome\src\8\log\app2.log (NOTSET)>]
default level：0
EffectiveLevel：30
DEBUG - 除錯
INFO - 資訊
WARNING - 警告

• 工作日誌檔內容：

WARNING - 警告

工作日誌接收器(Log viewer)

使用SocketHandler即時監看訊息，這個功能非常有用，一邊請使用者操作，另一邊我們可以工作日誌接收器監看訊息，可以迅速找出發生問題的程式碼。

範例8. 使用SocketHandler即時監看訊息。

1. 主程式名稱為socket_log_server.py，負責傳送工作日誌訊息。

import os, logging
from logging.handlers import SocketHandler, DEFAULT_TCP_LOGGING_PORT

# 自訂工作日誌(logger)
logger = logging.getLogger(__name__)

# 訂定 handlers
socketHandler = SocketHandler('localhost', DEFAULT_TCP_LOGGING_PORT)
# 指定logger的handlers
logger.addHandler(socketHandler)

# 設定等級
logger.setLevel("DEBUG")

# 測試
while True:
    msg = input('請輸入訊息:')
    if len(msg) == 0: break
    logger.debug(msg)

2. 建立工作日誌接收器，程式參閱Python官方指引，由於程式碼較多，僅節錄通訊的部分，其他請看範例檔socket_receiver.py。

# 監聽工作日誌
class LogRecordSocketReceiver(socketserver.ThreadingTCPServer):
    """
    Simple TCP socket-based logging receiver suitable for testing.
    """

    allow_reuse_address = True

    def __init__(self, host='localhost',
                 port=DEFAULT_TCP_LOGGING_PORT,
                 handler=LogRecordStreamHandler):
        socketserver.ThreadingTCPServer.__init__(self, (host, port), handler)
        self.abort = 0
        self.timeout = 1
        self.logname = None

    # 逾時則結束程式
    def serve_until_stopped(self):
        import select
        abort = 0
        while not abort:
            rd, wr, ex = select.select([self.socket.fileno()],
                                       [], [],
                                       self.timeout)
            if rd:
                self.handle_request()
            abort = self.abort
            
# 呼叫LogRecordSocketReceiver，建立工作日誌接收器
def main():
    logging.basicConfig(
        format='%(relativeCreated)5d %(name)-15s %(levelname)-8s %(message)s')
    tcpserver = LogRecordSocketReceiver()
    print('About to start TCP server...')
    tcpserver.serve_until_stopped()

3. 測試：先啟動server，再至另一個終端機或cmd執行工作日誌接收器。

python socket_log_server.py
python socket_receiver.py

5. 執行結果：在server的螢幕輸入訊息，要結束程式直接按ENTER。

請輸入訊息:123
請輸入訊息:1234
請輸入訊息:abc
請輸入訊息:

6. 工作日誌接收器會同步收到訊息。

74949 __main__        DEBUG    1234
81050 __main__        DEBUG    abc

結語

工作日誌(Log)是每個中大型系統必備的機制，不論我們使用甚麼程式語言，尤其是即時監看，在已上線的環境中，比較有效能協助找出bugs的利器，在訂定系統架構時，一定要審慎規劃。

本文主要參考以下資訊：

1. Logging in Python。
2. Logging HOWTO。
3. Logging handlers。

本系列的程式碼會統一放在GitHub，本篇的程式放在src/8資料夾，歡迎讀者下載測試，如有錯誤或疏漏，請不吝指正。